fix(logging): close three ways the JSON fallback still lost the record by groupthinking · Pull Request #1515 · groupthinking/EventRelay

groupthinking · 2026-08-07T21:24:27Z

Canonical issue

Outcome

A JSON log record is no longer lost when the recovery path after a serialization error itself raises, when a value forges __class__ = str, when an int exceeds the digit-string cap, or when a non-finite float would emit invalid JSON. The guarantee is a property of the code (final constant-record tier), not of the failure modes anticipated in #1491.

Scope

Included: hardened _format_json recovery (describe exception, exact-type scalar filter, int bit-length bound, allow_nan=False), +10 unit tests in the existing CWE-117 suite
Explicitly excluded: unrelated log formatters; product/API surface changes

Risk

Risk level: low
Failure mode: fallback text is slightly coarser on rare paths; record still emits
Rollback: git revert — no schema or config change

Verification

+10 focused tests fail on unfixed head and pass after
Pre-existing 26 CWE-117 tests unchanged
test, bandit, trivy, security scans green on PR head
Governance re-run after this body fix

Production evidence

Logging-only change. Unit tests carry the evidence; Vercel preview is not a meaningful runtime signal for Python logging.

Agent handoff

Land after Canonical issue + PR Governance pass. Follow-up to #1491 / #1452 residual holes.

#1491 wrapped the `json.dumps` call so a bad enrichment could not cost the whole record, and stated the guarantee as "never lose a record to a serialization error". The wrapper holds for the two inputs it was written against, but the *recovery* path it added can itself raise — so the guarantee covered the anticipated failures rather than the property. Measured against a real handler on 8517bf8, healthy -> poisoned -> healthy: | input | before | after | |------------------------------------|--------|-------| | circular container | 3/3 | 3/3 | | exploding `__str__` | 3/3 | 3/3 | | exception whose own `__str__` raises | 2/3 | 3/3 | | value forging `__class__ = str` | 2/3 | 3/3 | | int past the 4300-digit cap | 2/3 | 3/3 | | non-finite float | 3/3* | 3/3 | * emitted, but as a bare `NaN`/`Infinity` literal, which is not valid JSON — a strict downstream parser rejects the record, which is the same loss moved to the consumer. Each cause, and the fix: * The fallback built `f"{type(exc).__name__}: {exc}"` directly. The exception it catches may be one raised from a call site's own `__str__`, so describing the failure became the failure. Now `_describe_exception`, which falls back to the type name. * The scalar filter used `isinstance`, which consults `__class__` and can be forged with a property returning `str`. `json` dispatches on the real runtime type, so such a value passed the filter and then raised in the fallback's own dump. Now matched on exact runtime type. * `int` is a scalar by every type test, but `json` renders ints via `str` and CPython caps that at `sys.get_int_max_str_digits()` (4300). Now bounded by `bit_length`, which avoids performing the conversion being guarded against. * `allow_nan=False`, so a non-finite float routes to the fallback and the record stays valid JSON instead of carrying a JavaScript literal. A final constant-record tier keeps the guarantee a property of the code rather than of the failure modes anticipated here — the exact gap #1452 was about. It is not reachable through any input above, and the comment says so. Tests: +10 in the existing CWE-117 file. All 10 fail against 8517bf8 and pass after (7 failed / 26 passed -> 33 passed); the pre-existing 26 are unchanged, so this does not weaken what #1491 established. Full `tests/unit` is unchanged at 1637 failed / 76 errors (missing optional deps in this environment) with +10 passed, i.e. no regressions. ruff clean; mypy unchanged at its 17 pre-existing errors in this module. Refs #1452 Co-Authored-By: Claude Opus 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01DHLdfqAJcfL9LPWC7Dp9Gx

vercel · 2026-08-07T21:24:32Z

The latest updates on your projects. Learn more about Vercel for GitHub.

Project	Deployment	Actions	Updated (UTC)
v0-uvai	Ready	Preview, v0	Aug 7, 2026 9:24pm

coderabbitai · 2026-08-07T21:24:35Z

Important

Review skipped

Auto reviews are limited based on label configuration.

🏷️ Required labels (at least one) (1)

[‘architecture-gap’, ‘bug’, ‘ci-cd’, ‘ci/cd’, ‘copilot-rabbit’, ‘documentation’, ‘duplicate’, ‘enhancement’, ‘frontend’, ‘github_actions’, ‘good first issue’, ‘help wanted’, ‘high-priority’, ‘invalid’, ‘javascript’, ‘ml-model’, ‘needs-triage’, ‘pipeline-critical’, ‘placeholder-code’, ‘priority:high’, ‘python’, ‘python:uv’, ‘question’, ‘styling’, ‘tests’, ‘v0’]

Please check the settings in the CodeRabbit UI or the .coderabbit.yaml file in this repository. To trigger a single review, invoke the @coderabbitai review command.

⚙️ Run configuration

Configuration used: Repository YAML (base), Repository UI (inherited), Organization UI (inherited)

Review profile: ASSERTIVE

Plan: Pro Plus

Run ID: d1e35d9c-1d02-4c23-9485-1ce4630f1f24

You can disable this status message by setting the reviews.review_status to false in the CodeRabbit configuration file.

Use the checkbox below for a quick retry:

🔍 Trigger review

Thanks for using CodeRabbit! It's free for OSS, and your support helps us grow. If you like it, consider giving us a shout-out.

❤️ Share

_{Comment @coderabbitai help to get the list of available commands.}

groupthinking · 2026-08-07T21:26:27Z

One remaining hole: `_describe_exception` is still defeatable by a hostile metaclass

This is the tenth PR against #1452 and the best of them — it is the only one that catches the oversized-int case, and the bit_length guard fails closed in the right direction (0.302 > log₁₀2 ≈ 0.30103, so the estimate can only over-count digits and never admit an unsafe value). No new PR from me; handing over the one delta I have instead, since re-deriving this cluster an eleventh time is the actual problem here.

The gap. _describe_exception's docstring says the type name "is a plain attribute lookup and is always safe." It is not. __name__ on a class is looked up on its metaclass, so a metaclass can define it as a raising property. Run against this PR's implementation verbatim:

=== #1515 _describe_exception vs hostile metaclass ===
  -> RAISES RuntimeError: __name__ exploded  => record LOST

Reproduction:

class HostileMeta(type):
    @property
    def __name__(cls): raise RuntimeError("__name__ exploded")

class NamelessExc(Exception, metaclass=HostileMeta):
    def __str__(self): raise RuntimeError("str exploded")

class RaisesNameless:
    def __str__(self): raise NamelessExc()

logger.info("poisoned", extra={"request_id": RaisesNameless()})   # record dropped

The except branch re-evaluates type(exc).__name__, which raises a second time — and this raise is outside any guard, so it propagates past the tier-3 constant and out of _format_json entirely. The last-resort record does not catch it.

CodeRabbit's suggested fix for this does not work. It recommended object.__getattribute__(type(exc), "__name__") on #1494. I tested it; it still routes through the metaclass descriptor:

type(exc).__name__                             -> RAISES RuntimeError
object.__getattribute__(type(exc),"__name__")  -> RAISES RuntimeError
type.__dict__["__name__"].__get__(type(exc))   -> OK: 'NamelessExc'

Fetching the descriptor from type.__dict__ and binding it directly is what bypasses the override, and it returns the ordinary name for ordinary classes.

Suggested patch:

def _describe_exception(exc: BaseException) -> str:
    try:
        return f"{type(exc).__name__}: {exc}"
    except Exception:  # noqa: BLE001 - fall through to a narrower attempt
        pass
    try:
        name: str = type.__dict__["__name__"].__get__(type(exc))
        return name
    except Exception:  # noqa: BLE001 - the fallback must not need a fallback
        return "UnrenderableException"

Verified: 'NamelessExc' for the hostile metaclass, 'Normal' for an ordinary exception with a raising __str__, 'ValueError: msg' for a healthy one.

And a test — this fails on the current head of this PR:

def test_hostile_metaclass_name_does_not_cost_the_record():
    records = _emit_three("json-hostile-metaclass", RaisesNameless())
    assert len(records) == 3
    poisoned = records[1]
    assert poisoned["message"] == "poisoned"
    assert poisoned["level"] == "INFO"
    assert poisoned["serialization_error"] == "NamelessExc"

Worth noting because it is the same failure shape this PR is fixing: test_describe_exception_survives_an_exception_that_cannot_be_stringified passes only because _NastyError has an ordinary metaclass, so it pins the guard against one of the two ways naming an exception can raise.

Everything else here holds up — I reproduced all four of your cases independently against b7a2da3 before finding this one.

Context on why this is PR #10

For whoever reviews this: nine earlier PRs (#1471, #1472, #1477, #1488, #1493, #1494, #1497, #1504) were opened against #1452 between 20:53 and 21:11 by concurrent unattended runs, and all nine were closed unmerged as duplicates of one another — in conflicting directions (#1494 closed for #1504; #1504 then closed for #1497; #1497 closed too). Net result: none of the follow-up fixes reached main, and all three original holes are live on b7a2da3 today. Measured just now:

exploding-__str__ exception  -> RECORD LOST
forged __class__             -> RECORD LOST
non-finite float             -> emitted, not strictly valid JSON

So this PR is not redundant with anything currently open — it is the only one left carrying the fix. It is worth landing rather than closing as "another duplicate."

Generated by Claude Code

github-actions · 2026-08-07T21:36:01Z

Dependency Review

✅ No vulnerabilities or license issues or OpenSSF Scorecard issues found.

Snapshot Warnings

⚠️: No snapshots were found for the head SHA a826ecf.

Ensure that dependencies are being submitted on PR branches and consider enabling retry-on-snapshot-warnings. See the documentation for more information and troubleshooting advice.

Scanned Files

None

linear-code · 2026-08-13T03:18:55Z

GRV-407

groupthinking · 2026-08-13T03:19:02Z

Re-triggering governance after fixing Closes #1525 and full template sections.

#1515 closed #1525's three residual holes and is on main. One path in the same function is still reachable, and it is the one its docstring asserts is safe: "The type name is a plain attribute lookup and is always safe." It is not. `__name__` on a class is looked up on its *metaclass*, so a metaclass defining `__name__` as a raising property defeats the `except` branch. That second raise happens outside any guard, so it propagates past the `_JSON_UNSERIALIZABLE_RECORD` tier and out of `_format_json` entirely, and `Handler.handleError` drops the record. The constant-record tier does not catch it. Measured on 5473bcc: 2 of 3 records reach the sink. `object.__getattribute__(type(exc), "__name__")` does not fix this -- it still routes through the metaclass descriptor: type(exc).__name__ -> RAISES object.__getattribute__(type(exc),"__name__") -> RAISES type.__dict__["__name__"].__get__(type(exc)) -> OK Binding the descriptor from `type.__dict__` bypasses an override and returns the ordinary name for ordinary classes, with a constant as the final floor. The docstring is corrected to state the guarantee the code provides. This is the same failure shape #1525 was filed about, one level down: the recovery step for a failure is itself able to fail. Verification on this head: 36 passed in tests/unit/test_logging_config_crlf.py (33 pre-existing, unchanged). Reverting only logging_config.py: 2 failed, 34 passed. The third new test, test_describe_exception_is_unchanged_for_ordinary_exceptions, passes on 5473bcc by design -- it guards the normal path against regression rather than pinning the fix, so it is excluded from the non-vacuity claim. ruff clean; mypy reports the same 17 pre-existing errors on both heads. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01Msg6kqkhiuW1ZiDv66sr4N

fix(logging): stop a hostile metaclass costing the record (#1576) #1515 closed #1525's three residual holes and is on main. One path in the same function is still reachable, and it is the one its docstring asserts is safe: "The type name is a plain attribute lookup and is always safe." It is not. `__name__` on a class is looked up on its *metaclass*, so a metaclass defining `__name__` as a raising property defeats the `except` branch. That second raise happens outside any guard, so it propagates past the `_JSON_UNSERIALIZABLE_RECORD` tier and out of `_format_json` entirely, and `Handler.handleError` drops the record. The constant-record tier does not catch it. Measured on 5473bcc: 2 of 3 records reach the sink. `object.__getattribute__(type(exc), "__name__")` does not fix this -- it still routes through the metaclass descriptor: type(exc).__name__ -> RAISES object.__getattribute__(type(exc),"__name__") -> RAISES type.__dict__["__name__"].__get__(type(exc)) -> OK Binding the descriptor from `type.__dict__` bypasses an override and returns the ordinary name for ordinary classes, with a constant as the final floor. The docstring is corrected to state the guarantee the code provides. This is the same failure shape #1525 was filed about, one level down: the recovery step for a failure is itself able to fail. Verification on this head: 36 passed in tests/unit/test_logging_config_crlf.py (33 pre-existing, unchanged). Reverting only logging_config.py: 2 failed, 34 passed. The third new test, test_describe_exception_is_unchanged_for_ordinary_exceptions, passes on 5473bcc by design -- it guards the normal path against regression rather than pinning the fix, so it is excluded from the non-vacuity claim. ruff clean; mypy reports the same 17 pre-existing errors on both heads. Claude-Session: https://claude.ai/code/session_01Msg6kqkhiuW1ZiDv66sr4N Co-authored-by: Claude <noreply@anthropic.com>

This was referenced Aug 7, 2026

test(web): pin both edges of the SSRF guard's IPv6 bit-mask ranges #1512

Merged

fix(logging): stop a hostile metaclass costing the record #1516

Merged

github-actions Bot added the python label Aug 7, 2026

github-actions Bot mentioned this pull request Aug 8, 2026

[automation] Repository drift report #1374

Closed

groupthinking mentioned this pull request Aug 13, 2026

fix(logging): residual JSON fallback can still drop records after #1491 #1525

Closed

3 tasks

groupthinking merged commit 35169d3 into main Aug 13, 2026
29 of 32 checks passed

groupthinking deleted the claude/clever-heisenberg-sooi99 branch August 13, 2026 03:18

groupthinking mentioned this pull request Aug 29, 2026

_describe_exception can still drop the record — type(exc).__name__ resolves through the metaclass #1576

Closed

groupthinking mentioned this pull request Aug 29, 2026

fix(security): sanitize user-controlled values in API logs (CWE-117 log injection) #810

Open

8 tasks

Navigation Menu

fix(logging): close three ways the JSON fallback still lost the record - #1515

fix(logging): close three ways the JSON fallback still lost the record#1515
groupthinking merged 1 commit into
mainfrom
claude/clever-heisenberg-sooi99

groupthinking commented Aug 7, 2026 •

edited

Loading

Uh oh!

vercel Bot commented Aug 7, 2026

Uh oh!

coderabbitai Bot commented Aug 7, 2026 •

edited

Loading

Review skipped

Uh oh!

groupthinking commented Aug 7, 2026

Uh oh!

github-actions Bot commented Aug 7, 2026

Uh oh!

Uh oh!

linear-code Bot commented Aug 13, 2026

Uh oh!

groupthinking commented Aug 13, 2026

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

2 participants

Conversation

groupthinking commented Aug 7, 2026 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Canonical issue

Outcome

Scope

Risk

Verification

Production evidence

Agent handoff

Uh oh!

vercel Bot commented Aug 7, 2026

Uh oh!

coderabbitai Bot commented Aug 7, 2026 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Review skipped

Uh oh!

groupthinking commented Aug 7, 2026

One remaining hole: _describe_exception is still defeatable by a hostile metaclass

Context on why this is PR #10

Uh oh!

github-actions Bot commented Aug 7, 2026

Dependency Review

Snapshot Warnings

Scanned Files

Uh oh!

Uh oh!

linear-code Bot commented Aug 13, 2026

Uh oh!

groupthinking commented Aug 13, 2026

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

2 participants

groupthinking commented Aug 7, 2026 •

edited

Loading

coderabbitai Bot commented Aug 7, 2026 •

edited

Loading

One remaining hole: `_describe_exception` is still defeatable by a hostile metaclass